RedshiftでELBのアクセスログ（9千万件）を解析してみた
はじめに
AWSチームのすずきです。
AWSが提供するDWHのAmazon Redshiftを利用して、S3上に保管されたELBのアクセスログ（15万ファイル、30GB、9千万レコード）を解析する機会がありましたので、 その内容について簡単に紹介させていただきます。
参考資料
今回の作業にあたって、以下の記事を参考とさせて頂きました。
環境情報
- Amazon Redshiftは、東京リージョン起動済みのクラスタを利用しました。（ds1.large×1台）
一時テーブル作成
CREATE TABLE IF NOT EXISTS tmp_elb_access_log ( request_time VARCHAR (32) ,elb VARCHAR (64) ,client_port VARCHAR (32) ,backend_port VARCHAR (32) ,request_processing_time FLOAT ,backend_processing_time FLOAT ,response_processing_time FLOAT ,elb_status_code VARCHAR (4) ,backend_status_code VARCHAR (4) ,received_bytes BIGINT ,sent_bytes BIGINT ,request VARCHAR (2048) ,user_agent VARCHAR (1024) ,ssl_cipher VARCHAR (64) ,ssl_protocol VARCHAR (64) ) ;
インポート
COPY tmp_elb_access_log FROM 's3://elb-logs-xxxxxxxx/dev/AWSLogs/nnnnnnnnnnnn/elasticloadbalancing/ap-northeast-1/' CREDENTIALS 'aws_iam_role=arn:aws:iam::nnnnnnnnnnnn:role/redshift-role-mmmmmmmmm' REGION 'ap-northeast-1' delimiter ' ' ACCEPTINVCHARS REMOVEQUOTES FILLRECORD MAXERROR AS 100000
設定内容
- S3(elb-logs-xxxxxxxx)はELBのアクセスログ出力先を指定しました
- CREDENTIALSは事前に用意したロール、またはアクセスキーを利用しました
- 参考: RedshiftのIAM Roles利用が可能となりました。
- S3,Redshiftはともに東京リージョンですが、リージョンを明示しました。（REGION 'ap-northeast-1' ）
- カラム区切りはスペースとしました（delimiter ' ' ）
- UTF8無効文字は「？」としてエラー回避しました（ACCEPTINVCHARS）
- 元データの引用符撤去しました（REMOVEQUOTES）
- カラム欠落レコード許容しました（FILLRECORD）
- エラーレコードは設定可能な最大数まで許容するとしました（AXERROR AS 100000）
確認
SELECT COUNT(1) FROM tmp_elb_access_log
解析テーブル作成
CREATE TABLE IF NOT EXISTS elb_access_log ( request_time TIMESTAMP ,request_date_jst TIMESTAMP ,elb VARCHAR (64) ,client_ip VARCHAR (64) ,client_port INTEGER ,backend_ip VARCHAR (64) ,backend_port INTEGER ,request_processing_time FLOAT ,backend_processing_time FLOAT ,response_processing_time FLOAT ,elb_status_code VARCHAR (4) ,backend_status_code VARCHAR (4) ,received_bytes BIGINT ,sent_bytes BIGINT ,request_method VARCHAR (8) ,request_uri VARCHAR (256) ,request_http_version VARCHAR (16) ,request_dir_1 VARCHAR (32) ,user_agent VARCHAR (256) ,ssl_cipher VARCHAR (64) ,ssl_protocol VARCHAR (64) ) DISTKEY (request_time) SORTKEY (request_date_jst, request_uri, request_dir_1, user_agent)
データ投入
INSERT INTO elb_access_log
(
SELECT
(request_time::TIMESTAMP) as request_time,
CONVERT_TIMEZONE('JST',request_time::date) as request_date_jst,
(elb::VARCHAR(64)) AS elb,
(NULLIF(SPLIT_PART(client_port, ':', 1), '-')::VARCHAR(64)) AS client_ip,
(NULLIF(SPLIT_PART(client_port, ':', 2), '-')::INTEGER) AS client_port,
case backend_port when '-' then NULL else SPLIT_PART(backend_port, ':', 1) end AS backend_ip,
case backend_port when '-' then NULL else SPLIT_PART(backend_port, ':', 2)::INTEGER end AS backend_port,
request_processing_time AS request_processing_time,
backend_processing_time AS backend_processing_time,
response_processing_time AS response_processing_time,
(NULLIF(elb_status_code, '-')::VARCHAR(4)) AS elb_status_code,
(NULLIF(backend_status_code, '-')::VARCHAR(4)) AS backend_status_code,
received_bytes,
sent_bytes,
(NULLIF(SPLIT_PART(request, ' ', 1), '-')::VARCHAR(8)) AS request_method,
(NULLIF(SPLIT_PART(request, ' ', 2), '-')::VARCHAR(256)) AS request_uri ,
(NULLIF(SPLIT_PART(request, ' ', 3), '-')::VARCHAR(16)) AS request_http_version,
(NULLIF(SPLIT_PART(request, '/', 4), '-')::VARCHAR(8)) AS request_dir_1,
(NULLIF(user_agent, '-')::VARCHAR(256)) AS user_agent,
(NULLIF(ssl_cipher, '-')::VARCHAR(64)) AS ssl_cipher ,
(NULLIF(ssl_protocol, '-')::VARCHAR(64)) AS ssl_protocol
FROM tmp_elb_access_log
WHERE request_time ~ '[2][0-9][0-9][0-9]-[0-1][0-9]-[0-3][0-9]'
)
;
処理概要
- アクセス時刻、TIMESTAMP型に変換します
- JSTでアクセス日時をもたせました。
- 配列カラム（port、request）は分割しました。
- 異常な時刻レコードは除外します。
アクセス解析例
backend_processing_timeの発生元ベスト10
SELECT SPLIT_PART(user_agent,'/',1) as UA ,SUM(backend_processing_time)/60/60::int AS sum_backend_time FROM elb_access_log WHERE request_time > SYSDATE-90 and user_agent not like 'Mozilla%' and user_agent not like 'Zabbix%' and user_agent not like 'Amazon%' and user_agent not like 'Incapsula%' and user_agent not like 'Docomo%' and user_agent not like 'SAMSUNG%' and user_agent not like 'Opera%' GROUP BY SPLIT_PART(user_agent,'/',1) ORDER BY sum_backend_time desc LIMIT 10
- ヘルスチェック、通常ブラウザからのアクセスは除外しました。
| 順位 | user_agent | 処理時間(h) |
|---|---|---|
| 1 | Owlin bot v3 http: | 91 |
| 2 | OSlackbot 1.0 (+https: | 75 |
| 3 | OTwitterbot | 31 |
| 4 | OAnemone | 26 |
| 5 | Obrain (+http: | 25 |
| 6 | OScrapy | 24 |
| 7 | OFeedly | 20 |
| 8 | OHatena::UserAgent | 18 |
| 9 | OPlagger | 17 |
| 10 | ORuby | 16 |
backend_processing_timeの発生先ベスト10
SELECT
request_uri
,(SUM(backend_processing_time)/60/60)::int AS sum_backend_time
FROM elb_access_log
WHERE request_time > SYSDATE-90
and request_dir_1 not in ('category','feed')
and request_uri != 'https://dev.classmethod.jp:80/'
GROUP BY request_uri
ORDER BY sum_backend_time desc
LIMIT 10
- 記事ページのみ対象としました
| 順位 | 表示ページ | 投稿日 | 作者 | 処理時間(h) |
|---|---|---|---|---|
| 1 | 非エンジニアに贈る「具体例でさらっと学ぶJSON」 | 2015年05月28日 | 都元ダイスケ | 9 |
| 2 | Windowsでシンボリックリンクを作る | 2014年04月23日 | 梶原裕 | 9 |
| 3 | [Excel] シートで非表示になっている名前の定義を消す方法 | 2013年05月01 | 諏訪 悠紀 | 8 |
| 4 | 第1回 はじめてのSpring framework | 2013年03月07日 | 都元ダイスケ | 8 |
| 5 | iOS 9 で追加された App Transport Security の概要 | 2015年08月11日 | 平屋真吾 | 7 |
| 6 | よく分かる！Android アプリのリリース手順のまとめ アドカレ2013 : SP #20 | 2013年12月20日 | 諏訪 悠紀 | 7 |
| 7 | MacBook Airの動作が重くなったのでメンテナンスしたら軽くなった件 | 2015年04月20日 | 横田 あかり | 7 |
| 8 | 間違えて貼った収入印紙を返金してもらう方法 | 2014年12月05日 | クニ吉 | 7 |
| 9 | Vagrantって流行ってるらしいけど何が便利なの？ | 2013年07月31日 | 袴田 | 6 |
| 10 | よく分かる！iOS アプリ開発に必要な証明書ファイルの作成方法 アドカレ2013 : SP #4 | 2013年12月04日 | おおはしりきたけ | 6 |
考察
- 公開直後、参照が集中する記事についてはキャッシュ経由の配信となりますが、ロングテールで、一定の需要が存在する記事がキャッシュの乗りが悪く、サーバ負荷になっている事が伺えました。
-
上記レスポンスタイムは、GoogleAnalyticsなどでも確認が可能ですが、サーバのレスポンスコードなどを組み合わせた解析や、全量ログを前提とした抽出にはRedshiftは大きな効果を発揮すると考えられます。
まとめ
今回、利用したRedshiftクラスタは、ds1.large、1台の最小構成でした。 USリージョンであれば1時間0.2$、EC2のc4.xlargeと同等の単価で利用ができる環境ですが、 S3からのインポート（COPY）、所要時間は20分程。一時テーブルが消費した容量は5GB強でした。
Redshiftに展開された約9000万レコードの解析、、先述のクエリの所要時間は30〜40秒。 充分な性能であったため、最適化などは未実施でしたが、 適切なキー設定やデータの最適化などで更なる高速化が期待できる状態でした。
SQLを利用した柔軟な解析、手軽に実施できるRedshift、ELBのアクセスログ解析にも有効でした。 ログ確認や活用などの手段として、是非ご活用ください。
